perm filename TPRINT.TIM[TIM,LSP]11 blob sn#754843 filedate 1984-05-15 generic text, type C, neo UTF8
COMMENT ⊗   VALID 00014 PAGES
C REC  PAGE   DESCRIPTION
C00001 00001
C00002 00002	 SAIL
C00003 00003	 TPRINT
C00004 00004	 NIL
C00008 00005	∂12-Oct-83  0715	jkf%ucbkim@Berkeley 	tprint   
C00023 00006	 SCORE dec 12, 1983
C00024 00007	 DEC780CL
C00025 00008	 InterLispVax 780
C00026 00009	 PSL-20 3.3
C00027 00010	 PSL-Cray 3.2
C00028 00011	 PSL-750 3.2
C00029 00012	 PSL-780 3.2
C00030 00013	 PSL-DN600 3.2
C00031 00014	 PSL-DN300 3.2
C00032 ENDMK
C⊗;
;;; SAIL

(fasload tprint)
(timit)

Into file (LPEND)
Timing performed on Sunday 09/12/82 at 15:25:22.
Cpu Time = 1.268
Elapsed Time = 245.45
Wholine Time = 6.1
GC Time = 0.0
Load Average Before  = 1.58466601
Load Average After   = 1.39642692
Average Load Average = 1.49054646
NIL 
Onto screen (PPSAVE)
Timing performed on Sunday 09/12/82 at 15:30:22.
Cpu Time = 0.81
Elapsed Time = 96.466666
Wholine Time = 6.51666665
GC Time = 0.0
Load Average Before  = 1.2683934
Load Average After   = 1.53600466
Average Load Average = 1.40219903
;;; TPRINT

D3
7/5/83
10x10 window, scrolling
Elapsed	5.55
CPU	5.55

D2
7/5/83
10x10 window, scrolling, with interrupts
Elapsed	29.2
CPU	29.2

D1
1/25/84 with interrupts, 10x10 window, scrolling.
Elapsed	34.1
CPU	34.1
GC	 0.0
;;; NIL
TPRINT

Fixnum arithmetic.
cpu=47.55,elapsed=58.31,pf=0

For whatever it's worth, NIL terminal i/o models ITS, and NIL performs
all of the cursor maintainance.  For simplicity, NIL doesn't do
block-mode output except when it knows it can.  So, when PRIN1
discovers that the print-name of a symbol can be output as-is, it
passes it on to the stream, which (in these cases) will discover that
there are no funny characters, which will cause the symbol print-names
to be output in block-mode.  (So, for number-of-characters output, it
would be faster with larger print-names.)  Various other (atomic)
things internally buffer and do string-outs, such as number printing.

For kicks, to isolate the PRIN1-type overhead from the terminal-io
overhead, doing the same thing with PRINC gives
cpu=34.4,elapsed=45.68,pf=0

There is also the fact that printing "to the default" prints to
standard-output, which is a synonym stream to terminal-io, so there is
message-forwarding for each individual message being sent.  It is a
feature rather than a bug that it effectively recomputes the output
destination for every i/o operation, so standard-output could be
changed at interrupt level, for instance.  Doing
(print test-pattern terminal-io) gives
cpu=36.66,elapsed=47.19,pf=15

And to just hack the i/o, doing a PRINC of a string containing the
characters output, that is,
(defvar test-string
  (with-output-to-string (s)
    (princ test-pattern s)))
(timer string-timit (princ test-string)),
gives:
cpu=4.13,elapsed=14.09,pf=0
What happens here is that princing a string just does one stream
operation (:oustr, i.e. zapping out the string), so everything then is
in the cursor and tty-io code.  Although it is doing block-mode
output, it is not going and outputting the entire string in one block,
becuase it has to go and do cursor-stuff (line wrap, continuation
columns, etc.)
∂12-Oct-83  0715	jkf%ucbkim@Berkeley 	tprint   
Received: from UCB-VAX by SU-AI with TCP/SMTP; 12 Oct 83  07:15:16 PDT
Received: from ucbkim.ARPA by ucbvax.ARPA (4.12/4.7)
	id AA05294; Wed, 12 Oct 83 06:37:01 PDT
Received: by ucbkim.ARPA (4.6/4.2)
	id AA29739; Wed, 12 Oct 83 06:30:54 PDT
Date: Wed, 12 Oct 83 06:30:54 PDT
From: John Foderaro (on an h19-u) <jkf%ucbkim@Berkeley>
Message-Id: <8310121330.AA29739@ucbkim.ARPA>
To: rpg@su-ai
Subject: tprint

--- Benchmark tprint run on ucbkim at Wed Oct 12 06:14:38 PDT 1983 by jkf
--- cpu usage: 6:14am up 1 day, 18:42, 9 users, load average: 0.94, 0.64, 0.36
Franz Lisp, Opus 38.81

=> [fasl tprint.o]
t
=> benchmark: test (file tprint) , tranlinks: on, localf: no
executing form: (print test-pattern)
((((((678.0 567.0 567.0 456.0 456.0 |345c|) |234b| (567.0 456.0 456.0 |345c| |34
qrs9 qrs9 opq8 opq8 mno7) klm6 (qrs9 opq8 opq8 mno7 mno7 klm6) ijk5) ghi4) efg3
) cde2) abc1)begin (72 182)
end (103 182)
runs 1
avg cpu time 0.5166666666666667

benchmark: test (file tprint) , tranlinks: off, localf: no
executing form: (print test-pattern)
((((((678.0 567.0 567.0 456.0 456.0 |345c|) |234b| (567.0 456.0 456.0 |345c| |34
 qrs9 qrs9 opq8 opq8 mno7) klm6 (qrs9 opq8 opq8 mno7 mno7 klm6) ijk5) ghi4) efg3
) cde2) abc1)begin (104 182)
end (135 182)
runs 1
avg cpu time 0.5166666666666667

nil
=> Franz Lisp, Opus 38.81

=> [fasl tprint-l.o]
t
=> benchmark: test (file tprint) , tranlinks: on, localf: yes
executing form: (print test-pattern)
((((((678.0 567.0 567.0 456.0 456.0 |345c|) |234b| (567.0 456.0 456.0 |345c| |34
qrs9 qrs9 opq8 opq8 mno7) klm6) ijk5 ((uvw1 stu0 stu0 qrs9 qrs9 opq8) mno7 (stu0
 qrs9 qrs9 opq8 opq8 mno7) klm6 (qrs9 opq8 opq8 mno7 mno7 klm6) ijk5) ghi4) efg3
) cde2) abc1)begin (62 181)
end (94 181)
runs 1
avg cpu time 0.5333333333333333

benchmark: test (file tprint) , tranlinks: off, localf: yes
executing form: (print test-pattern)
((((((678.0 567.0 567.0 456.0 456.0 |345c|) |234b| (567.0 456.0 456.0 |345c| |34
 qrs9 qrs9 opq8 opq8 mno7) klm6 (qrs9 opq8 opq8 mno7 mno7 klm6) ijk5) ghi4) efg3
) cde2) abc1)begin (95 181)
end (124 181)
runs 1
avg cpu time 0.4833333333333333

nil
=> Franz Lisp, Opus 38.81

=> [load tprint.l]
[fasl benchmac.o]
t
=> benchmark: test (file tprint) , tranlinks: on, interpreted 
executing form: (print test-pattern)
((((((678.0 567.0 567.0 456.0 456.0 |345c|) |234b| (567.0 456.0 456.0 |345c| |34
qrs9 qrs9 opq8 opq8 mno7) klm6 (qrs9 opq8 opq8 mno7 mno7 klm6) ijk5) ghi4) efg3
) cde2) abc1)begin (1006 662)
end (1039 662)
runs 1
avg cpu time 0.55

benchmark: test (file tprint) , tranlinks: off, interpreted 
executing form: (print test-pattern)
((((((678.0 567.0 567.0 456.0 456.0 |345c|) |234b| (567.0 456.0 456.0 |345c| |34
 qrs9 qrs9 opq8 opq8 mno7) klm6 (qrs9 opq8 opq8 mno7 mno7 klm6) ijk5) ghi4) efg3
) cde2) abc1)begin (1042 662)
end (1073 662)
runs 1
avg cpu time 0.5166666666666667

nil
=> --- cpu usage: 6:15am up 1 day, 18:43, 9 users, load average: 1.59, 0.88, 0.47
--- end of benchmark tprint


--- Benchmark tprint run on ucbmatisse at Mon Oct 10 07:56:19 PDT 1983 by jkf
--- cpu usage: 7:56am up 2 days, 16:25, 3 users, load average: 0.97, 0.55, 0.28
Franz Lisp, Opus 38.81

=> [fasl tprint.o]
t
=> benchmark: test (file tprint) , tranlinks: on, localf: no
executing form: (print test-pattern)
((((((678.0 567.0 567.0 456.0 456.0 |345c|) |234b| (567.0 456.0 456.0 |345c| |34
 qrs9 qrs9 opq8 opq8 mno7) klm6 (qrs9 opq8 opq8 mno7 mno7 klm6) ijk5) ghi4) efg3
) cde2) abc1)begin (110 202)
end (162 202)
runs 1
avg cpu time 0.8666666666666667

benchmark: test (file tprint) , tranlinks: off, localf: no
executing form: (print test-pattern)
((((((678.0 567.0 567.0 456.0 456.0 |345c|) |234b| (567.0 456.0 456.0 |345c| |34
qrs9 qrs9 opq8 opq8 mno7) klm6) ijk5 ((uvw1 stu0 stu0 qrs9 qrs9 opq8) mno7 (stu0
 qrs9 qrs9 opq8 opq8 mno7) klm6 (qrs9 opq8 opq8 mno7 mno7 klm6) ijk5) ghi4) efg3
) cde2) abc1)begin (165 202)
end (217 202)
runs 1
avg cpu time 0.8666666666666667

nil
=> Franz Lisp, Opus 38.81

=> [fasl tprint-l.o]
t
=> benchmark: test (file tprint) , tranlinks: on, localf: yes
executing form: (print test-pattern)
((((((678.0 567.0 567.0 456.0 456.0 |345c|) |234b| (567.0 456.0 456.0 |345c| |34
qrs9 qrs9 opq8 opq8 mno7) klm6) ijk5 ((uvw1 stu0 stu0 qrs9 qrs9 opq8) mno7 (stu0
 qrs9 qrs9 opq8 opq8 mno7) klm6 (qrs9 opq8 opq8 mno7 mno7 klm6) ijk5) ghi4) efg3
) cde2) abc1)begin (98 203)
end (151 203)
runs 1
avg cpu time 0.8833333333333333

benchmark: test (file tprint) , tranlinks: off, localf: yes
executing form: (print test-pattern)
((((((678.0 567.0 567.0 456.0 456.0 |345c|) |234b| (567.0 456.0 456.0 |345c| |34
qrs9 qrs9 opq8 opq8 mno7) klm6) ijk5 ((uvw1 stu0 stu0 qrs9 qrs9 opq8) mno7 (stu0
 qrs9 qrs9 opq8 opq8 mno7) klm6 (qrs9 opq8 opq8 mno7 mno7 klm6) ijk5) ghi4) efg3
) cde2) abc1)begin (152 203)
end (204 203)
runs 1
avg cpu time 0.8666666666666667

nil
=> Franz Lisp, Opus 38.81

=> [load tprint.l]
[fasl benchmac.o]
t
=> benchmark: test (file tprint) , tranlinks: on, interpreted 
executing form: (print test-pattern)
((((((678.0 567.0 567.0 456.0 456.0 |345c|) |234b| (567.0 456.0 456.0 |345c| |34
qrs9 qrs9 opq8 opq8 mno7) klm6) ijk5 ((uvw1 stu0 stu0 qrs9 qrs9 opq8) mno7 (stu0
 qrs9 qrs9 opq8 opq8 mno7) klm6 (qrs9 opq8 opq8 mno7 mno7 klm6) ijk5) ghi4) efg3
) cde2) abc1)begin (1628 1010)
end (1680 1010)
runs 1
avg cpu time 0.8666666666666667

benchmark: test (file tprint) , tranlinks: off, interpreted 
executing form: (print test-pattern)
((((((678.0 567.0 567.0 456.0 456.0 |345c|) |234b| (567.0 456.0 456.0 |345c| |34
qrs9 qrs9 opq8 opq8 mno7) klm6) ijk5 ((uvw1 stu0 stu0 qrs9 qrs9 opq8) mno7 (stu0
 qrs9 qrs9 opq8 opq8 mno7) klm6 (qrs9 opq8 opq8 mno7 mno7 klm6) ijk5) ghi4) efg3
) cde2) abc1)begin (1684 1010)
end (1736 1010)
runs 1
avg cpu time 0.8666666666666667

nil
=> --- cpu usage: 7:57am up 2 days, 16:26, 2 users, load average: 1.24, 0.73, 0.37
--- end of benchmark tprint


--- Benchmark tprint run on ucbmike at Wed Oct 12 06:20:53 PDT 1983 by jkf
--- cpu usage: 6:20am up 14:32, 1 users, load average: 0.73, 0.54, 0.31
Franz Lisp, Opus 38.79
-> [fasl tprint.o]
t
-> benchmark: test (file tprint) , tranlinks: on, localf: no
executing form: (print test-pattern)
((((((678.0 567.0 567.0 456.0 456.0 |345c|) |234b| (567.0 456.0 456.0 |345c| |34
qrs9 qrs9 opq8 opq8 mno7) klm6) ijk5 ((uvw1 stu0 stu0 qrs9 qrs9 opq8) mno7 (stu0
 qrs9 qrs9 opq8 opq8 mno7) klm6 (qrs9 opq8 opq8 mno7 mno7 klm6) ijk5) ghi4) efg3
) cde2) abc1)begin (137 340)
end (236 340)
runs 1
avg cpu time 1.65

benchmark: test (file tprint) , tranlinks: off, localf: no
executing form: (print test-pattern)
((((((678.0 567.0 567.0 456.0 456.0 |345c|) |234b| (567.0 456.0 456.0 |345c| |34
qrs9 qrs9 opq8 opq8 mno7) klm6) ijk5 ((uvw1 stu0 stu0 qrs9 qrs9 opq8) mno7 (stu0
 qrs9 qrs9 opq8 opq8 mno7) klm6 (qrs9 opq8 opq8 mno7 mno7 klm6) ijk5) ghi4) efg3
) cde2) abc1)begin (239 340)
end (336 340)
runs 1
avg cpu time 1.616666666666667

nil
-> Franz Lisp, Opus 38.79
-> [fasl tprint-l.o]
t
-> benchmark: test (file tprint) , tranlinks: on, localf: yes
executing form: (print test-pattern)
((((((678.0 567.0 567.0 456.0 456.0 |345c|) |234b| (567.0 456.0 456.0 |345c| |34
qrs9 qrs9 opq8 opq8 mno7) klm6) ijk5 ((uvw1 stu0 stu0 qrs9 qrs9 opq8) mno7 (stu0
 qrs9 qrs9 opq8 opq8 mno7) klm6 (qrs9 opq8 opq8 mno7 mno7 klm6) ijk5) ghi4) efg3
) cde2) abc1)begin (116 341)
end (213 341)
runs 1
avg cpu time 1.616666666666667

benchmark: test (file tprint) , tranlinks: off, localf: yes
executing form: (print test-pattern)
((((((678.0 567.0 567.0 456.0 456.0 |345c|) |234b| (567.0 456.0 456.0 |345c| |34
qrs9 qrs9 opq8 opq8 mno7) klm6) ijk5 ((uvw1 stu0 stu0 qrs9 qrs9 opq8) mno7 (stu0
 qrs9 qrs9 opq8 opq8 mno7) klm6 (qrs9 opq8 opq8 mno7 mno7 klm6) ijk5) ghi4) efg3
) cde2) abc1)begin (215 341)
end (314 341)
runs 1
avg cpu time 1.65

nil
-> Franz Lisp, Opus 38.79
-> [load tprint.l]
[fasl benchmac.o]
t
-> benchmark: test (file tprint) , tranlinks: on, interpreted 
executing form: (print test-pattern)
((((((678.0 567.0 567.0 456.0 456.0 |345c|) |234b| (567.0 456.0 456.0 |345c| |34
qrs9 qrs9 opq8 opq8 mno7) klm6) ijk5 ((uvw1 stu0 stu0 qrs9 qrs9 opq8) mno7 (stu0
 qrs9 qrs9 opq8 opq8 mno7) klm6 (qrs9 opq8 opq8 mno7 mno7 klm6) ijk5) ghi4) efg3
) cde2) abc1)begin (725 412)
end (821 412)
runs 1
avg cpu time 1.6

benchmark: test (file tprint) , tranlinks: off, interpreted 
executing form: (print test-pattern)
((((((678.0 567.0 567.0 456.0 456.0 |345c|) |234b| (567.0 456.0 456.0 |345c| |34
qrs9 qrs9 opq8 opq8 mno7) klm6) ijk5 ((uvw1 stu0 stu0 qrs9 qrs9 opq8) mno7 (stu0
 qrs9 qrs9 opq8 opq8 mno7) klm6 (qrs9 opq8 opq8 mno7 mno7 klm6) ijk5) ghi4) efg3
) cde2) abc1)begin (826 412)
end (921 412)
runs 1
avg cpu time 1.583333333333333

nil
-> --- cpu usage: 6:22am up 14:33, 1 users, load average: 0.96, 0.67, 0.38
--- end of benchmark tprint


;;; SCORE dec 12, 1983

4.727 seconds
0.0 gc
;;; DEC780CL

	cpu + probability x gc
TPRINT	28
;;; InterLispVax 780

(PRINT TESTPATTERN) takes 11.472 seconds

;;; PSL-20 3.3

tprint test
Timing performed on DEC-20
23-Mar-84 05:09:58 .
........................................
Cpu (- GC) Time = 4.253 secs
Elapsed Time = 12.0 secs
GC Time = 0.0 secs
Load Average Before  = 1.4
Load Average After   = 1.4
Average Load Average = 1.4
;;; PSL-Cray 3.2
;;; Times are in milliseconds

 09:04:04 011:21.576 tprint test$2 π
 09:11:03 012:35.839 Cpu (- GC) Time = 189.95300000 secs$2 π
 09:11:05 012:36.359 Elapsed Time = 0. secs    
 09:11:07 012:36.880 GC Time = 0. secs 
 09:11:09 012:37.400 Load Average Before  = 0  
 09:11:11 012:37.920 Load Average After   = 0  
 09:11:13 012:38.440 Average Load Average = 0. 
;;; PSL-750 3.2

Cpu (- GC) Time = 4.284 secs
Elapsed Time = 0.0 secs
GC Time = 0.0 secs
Load Average Before  = 0
Load Average After   = 0
Average Load Average = 0.0
;;; PSL-780 3.2

Cpu (- GC) Time = 1.921 secs
Elapsed Time = 0.0 secs
GC Time = 0.0 secs
Load Average Before  = 0
Load Average After   = 0
Average Load Average = 0.0
;;; PSL-DN600 3.2

Cpu (- GC) Time = 2.731 secs
Elapsed Time = 0.0 secs
GC Time = 0.0 secs
Load Average Before  = 0
Load Average After   = 0
Average Load Average = 0.0
;;; PSL-DN300 3.2

Cpu (- GC) Time = 2.724 secs
Elapsed Time = 0.0 secs
GC Time = 0.0 secs
Load Average Before  = 0
Load Average After   = 0
Average Load Average = 0.0